#include "StdAfx.h"
#include "SimpleLoggerImpl.h"
#include "WindowsUtility.h"

namespace RoomFW {

SimpleLoggerImpl::SimpleLoggerImpl(void) :
	console_(false),
	maxLines_(4096),
	debugOutput_(false),
	file_(false),
	fileName_(),
	maxFileSize_(0),
	curFileSize_(0),
	maxFiles_(0),
	curFileIndex_(0),
	fileStartTimeString_(),
	verbosity_(LV_ALL),
	frequency_(),
	startTime_(),
	outStream_(0),
	outFileStream_(),
	outMemStream_(),
	cached_(false),
	allSynch_(),
	stopEvent_(),
	logQueue_(),
	queueSynch_(),
	queueEvent_(),
	stdInHandle_(0),
	stdInStream_(0),
	stdInFile_(0),
	stdOutHandle_(0),
	stdOutStream_(0),
	stdOutFile_(0),
	stdErrHandle_(0),
	stdErrStream_(0),
	stdErrFile_(0),
	isLvError_(),
	isLvWarning_(),
	isLvSystem_(),
	isLvSoftware_(),
	isLvMessage_(),
	isLvTrace_(),
	isLvSpeed_(),
	isLvSpeed2_()
{
	VERIFY(::QueryPerformanceFrequency(&frequency_));
	VERIFY(::QueryPerformanceCounter(&startTime_));

	// This has to be done here for performance reasons.
	VERIFY(isLvError_.create(true, true));
	VERIFY(isLvWarning_.create(true, true));
	VERIFY(isLvSystem_.create(true, true));
	VERIFY(isLvSoftware_.create(true, true));
	VERIFY(isLvMessage_.create(true, true));
	VERIFY(isLvTrace_.create(true, true));
	VERIFY(isLvSpeed_.create(true, true));
	VERIFY(isLvSpeed2_.create(true, true));

	// Startup date/time in all log file names (except current).
	this->initFileDateTimeString();

	// Just get/format processName_ once and store in this singleton for future reference.
    
	// See http://msdn.microsoft.com/en-us/library/ms683197(VS.85).aspx for GetModuleFileName
	TCHAR szPath[MAX_PATH];
    if(GetModuleFileName( NULL, szPath, MAX_PATH))
    {
		// GetModuleFileName returns a string like "c:\shansohn\src\SE500Dev\Development\DualLane\SpiLegacy\EXE\Sentry\Debug\SPId.exe"
		// We'd like the processName_ to be something like "Spid".
        processName_ = szPath;
		std::size_t processNameStart = processName_.rfind("\\");
		if (processNameStart != std::string::npos)
		{
			processNameStart++;	// advance past the backslash.
			std::size_t dotExe = processName_.rfind(".exe");
			if (dotExe != std::string::npos)
			{
				std::size_t nameLength = dotExe - processNameStart;
				processName_ = processName_.substr(processNameStart, nameLength);
			}
		}
    }
	else
		processName_ = itostr(::GetCurrentProcessId());
}

SimpleLoggerImpl::~SimpleLoggerImpl(void)
{
	this->stop(); // Thread derived destructors should always stop().
}

SimpleLoggerImpl& SimpleLoggerImpl::Instance(void)
{
	static SimpleLoggerImpl inst;
	return inst;
}

void SimpleLoggerImpl::setConsole(bool enable, DWORD maxLines)
{
	CriticalSectionGuard g(allSynch_);

	// Skip if no changes
	if ((enable != console_) || (maxLines != maxLines_))
	{
		if (console_ && (maxLines_ > 0))
		{
			VERIFY(::FreeConsole());
			// The following calls fail.  Apparently they're already closed by FreeConsole().
			//VERIFY(!::fclose(stdInFile_))
			//VERIFY(!::fclose(stdOutFile_))
			//VERIFY(!::fclose(stdErrFile_))
			//VERIFY(!::_close(stdInStream_))
			//VERIFY(!::_close(stdOutStream_))
			//VERIFY(!::_close(stdErrStream_))
			//VERIFY(::CloseHandle(stdInHandle_))
			//VERIFY(::CloseHandle(stdOutHandle_))
			//VERIFY(::CloseHandle(stdErrHandle_))
		}
		console_ = enable;
		maxLines_ = maxLines;
		if (console_ && (maxLines > 0))
		{
			// If we allocated a console for a GUI app, it needs to be initialized.
			if (::AllocConsole())
			{
				// Set the screen buffer to specified number of lines.
				stdOutHandle_ = ::GetStdHandle(STD_OUTPUT_HANDLE);
				CONSOLE_SCREEN_BUFFER_INFO coninfo;
				::GetConsoleScreenBufferInfo(stdOutHandle_, &coninfo);
				coninfo.dwSize.Y = maxLines;
				::SetConsoleScreenBufferSize(stdOutHandle_,	coninfo.dwSize);

				// Redirect unbuffered STDOUT to the console.
				stdOutStream_ = ::_open_osfhandle(reinterpret_cast<intptr_t>(stdOutHandle_), _O_TEXT);
				stdOutFile_ = ::_fdopen(stdOutStream_, "w");
				*stdout = *stdOutFile_;
				::setvbuf(stdout, NULL, _IONBF, 0);

				// Redirect unbuffered STDIN to the console.
				stdInHandle_ = ::GetStdHandle(STD_INPUT_HANDLE);
				stdInStream_ = ::_open_osfhandle(reinterpret_cast<intptr_t>(stdInHandle_), _O_TEXT);
				stdInFile_ = ::_fdopen(stdInStream_, "r");
				*stdin = *stdInFile_;
				::setvbuf(stdin, NULL, _IONBF, 0);

				// Redirect unbuffered STDERR to the console.
				stdErrHandle_ = ::GetStdHandle(STD_ERROR_HANDLE);
				stdErrStream_ = ::_open_osfhandle(reinterpret_cast<intptr_t>(stdErrHandle_), _O_TEXT);
				stdErrFile_ = ::_fdopen(stdErrStream_, "w");
				*stderr = *stdErrFile_;
				::setvbuf(stderr, NULL, _IONBF, 0);

				// Make cout, cin, and cerr point to console as well.
				std::ios::sync_with_stdio();
			}
		}
	}
}

void SimpleLoggerImpl::setFile(bool enable, const char* fileName, size_t maxSize, size_t maxFiles, bool cached)
{
	CriticalSectionGuard g(allSynch_);

	// Skip if no changes
	if ((enable != file_) || (fileName != fileName_) || (maxSize != maxFileSize_) || (cached != cached_))
	{
		// Close existing file.
		if (file_ && !fileName_.empty())
		{
			this->timestampFile();
			if (cached_)
			{
				outFileStream_ << outMemStream_.str();
				outMemStream_.str("");
			}
			outFileStream_.close();
			this->renameLogFile();
		}

		// Save args
		file_ = enable;
		fileName_ = (0 != fileName) ? fileName : "";
		maxFileSize_ = maxSize;
		curFileSize_ = 0; // Because we're starting a new file.
		maxFiles_ = maxFiles;
		// Don't update curFileIndex_.  If maxFiles is reduced, current index doesn't change.
		cached_ = cached;

		// Open new file.
		if (file_ && !fileName_.empty())
		{
			outFileStream_.open(fileName);
			ASSERT(!outFileStream_.fail()); // Can't log here, so assert...
			if (!outFileStream_.is_open())
			{
				file_ = false;
				fileName_.clear();
				cached_ = false;
				outStream_ = 0;
			}
			else
			{
				if (cached_)
				{
					outStream_ = &outMemStream_;
				}
				else
				{
					outStream_ = &outFileStream_;
				}
				this->timestampFile();
			}
		}
	}
}

std::string SimpleLoggerImpl::getFileName() const
{
	return file_ ? fileName_ : "";
}

void SimpleLoggerImpl::setDebugOutput(bool enable)
{
	CriticalSectionGuard g(allSynch_);
	debugOutput_ = enable;
}

void SimpleLoggerImpl::setVerbosity(uint32_t verbosity)
{
	{CriticalSectionGuard g(allSynch_);
		verbosity_ = verbosity;
	}
	if (LV_ERROR & verbosity)
	{
		VERIFY(isLvError_.set());
	}
	else
	{
		VERIFY(isLvError_.reset());
	}
	if (LV_WARNING & verbosity)
	{
		VERIFY(isLvWarning_.set());
	}
	else
	{
		VERIFY(isLvWarning_.reset());
	}
	if (LV_SYSTEM & verbosity)
	{
		VERIFY(isLvSystem_.set());
	}
	else
	{
		VERIFY(isLvSystem_.reset());
	}
	if (LV_SOFTWARE & verbosity)
	{
		VERIFY(isLvSoftware_.set());
	}
	else
	{
		VERIFY(isLvSoftware_.reset());
	}
	if (LV_MESSAGE & verbosity)
	{
		VERIFY(isLvMessage_.set());
	}
	else
	{
		VERIFY(isLvMessage_.reset());
	}
	if (LV_TRACE & verbosity)
	{
		VERIFY(isLvTrace_.set());
	}
	else
	{
		VERIFY(isLvTrace_.reset());
	}
	if (LV_SPEED & verbosity)
	{
		VERIFY(isLvSpeed_.set());
	}
	else
	{
		VERIFY(isLvSpeed_.reset());
	}
	if (LV_SPEED2 & verbosity)
	{
		VERIFY(isLvSpeed2_.set());
	}
	else
	{
		VERIFY(isLvSpeed2_.reset());
	}
}

void SimpleLoggerImpl::log(LoggingVerbosity verbosity, const char* file, const int line, const char* text)
{
	if (!this->isRunning())
		// Logging is probably disabled.  Just return without logging anything.
		return;

	// Check if logging this verbosity.
	bool doLog = false;
	{CriticalSectionGuard g(allSynch_);
		doLog = (verbosity & verbosity_) ? true : false;
	}
	if (doLog)
	{
		std::string threadName;

		// Get current time and difference from start time.
		LARGE_INTEGER timestamp;
		VERIFY(::QueryPerformanceCounter(&timestamp));
		LARGE_INTEGER deltaTime;
		{CriticalSectionGuard g(allSynch_);
#ifdef _LOG_RELATIVE_TIME_
			deltaTime.QuadPart = timestamp.QuadPart - startTime_.QuadPart;
#else
			deltaTime.QuadPart = timestamp.QuadPart;
#endif
//#define _LOG_THREAD_ID_
#ifdef _LOG_THREAD_ID_
			threadName = itostr(::GetCurrentThreadId());
#endif
		}
		// Save the log entry.
		EntrySP entry(new Entry(deltaTime, processName_, threadName, verbosity, file, line, text));
		{CriticalSectionGuard g(queueSynch_);
			logQueue_.push(entry);
			queueEvent_.set();
		}
	}
}

void SimpleLoggerImpl::logV(LoggingVerbosity verbosity, const char* file, const int line, const char* format, ...)
{
	// Format log text
	static const size_t bufSize = 2048;
	char buf[bufSize];
	::ZeroMemory(buf, bufSize);
	va_list args;
	va_start(args, format);
	::_vsnprintf_s(buf, bufSize, _TRUNCATE, format, args);
	va_end(args);

	// Save the log entry.
	this->log(verbosity, file, line, buf);
}

bool SimpleLoggerImpl::isLvError() const
{
	return isLvError_.wait(0);
}

bool SimpleLoggerImpl::isLvWarning() const
{
	return isLvWarning_.wait(0);
}

bool SimpleLoggerImpl::isLvSystem() const
{
	return isLvSystem_.wait(0);
}

bool SimpleLoggerImpl::isLvSoftware() const
{
	return isLvSoftware_.wait(0);
}

bool SimpleLoggerImpl::isLvMessage() const
{
	return isLvMessage_.wait(0);
}

bool SimpleLoggerImpl::isLvTrace() const
{
	return isLvTrace_.wait(0);
}

bool SimpleLoggerImpl::isLvSpeed() const
{
	return isLvSpeed_.wait(0);
}

bool SimpleLoggerImpl::isLvSpeed2() const
{
	return isLvSpeed2_.wait(0);
}

bool SimpleLoggerImpl::initializeObject(void)
{
	bool retVal = true;
	if ((0 == stopEvent_) || (0 == queueEvent_))
	{
		retVal = (stopEvent_.create() && queueEvent_.create());
	}
	return retVal;
}

bool SimpleLoggerImpl::waitEvent(void)
{
	// Create array of wait handles.
	const HANDLE waitObjs[] = {stopEvent_, queueEvent_};
	const size_t waitObjsSize = sizeof(waitObjs) / sizeof(HANDLE);

	// Run until stop signaled.
	DWORD ret = ::WaitForMultipleObjects(waitObjsSize, waitObjs, false, INFINITE);
	SHOW_LAST_ERROR((WAIT_FAILED != ret), "SimpleLoggerImpl::waitEvent", "::WaitForMultipleObjects");
	return ((WAIT_OBJECT_0 + 1) == ret);
}

bool SimpleLoggerImpl::handleEvent(void)
{
	this->emptyQueue();
	return true;
}

void SimpleLoggerImpl::signalStop(void)
{
	stopEvent_.set();
}

void SimpleLoggerImpl::onStop(void)
{
	this->emptyQueue();
	this->setFile(false);
}

void SimpleLoggerImpl::emptyQueue(void)
{
	EntrySP entry = this->pop();
	while (0 != entry)
	{
		{CriticalSectionGuard g(allSynch_);
			std::string logText = this->format(entry);
			if (console_)
			{
				std::cout << logText << std::endl;
			}
			if (file_)
			{
				if (maxFileSize_ && ((curFileSize_ += logText.size()) > maxFileSize_))
				{
					this->startNewFile();
				}
				(*outStream_) << logText << std::endl;
			}
			if (debugOutput_)
			{
				::OutputDebugString((logText + "\n").c_str());
			}
		}
		entry = this->pop();
	}
}

SimpleLoggerImpl::EntrySP SimpleLoggerImpl::pop(void)
{
	EntrySP retVal;
	CriticalSectionGuard g(queueSynch_);
	if (!logQueue_.empty())
	{
		retVal = logQueue_.front();
		logQueue_.pop();
	}
	return retVal;
}

std::string SimpleLoggerImpl::itostr(DWORD dword)
{
#define BASE_10 10		// Radix for _itoa_s
	int num = dword;
	char tempBuffer[100];
	::_itoa_s(num, tempBuffer, (sizeof(tempBuffer)/sizeof(tempBuffer[0])), BASE_10);
	return tempBuffer;
}

std::string SimpleLoggerImpl::format(EntrySP entry)
{
	std::ostringstream os;
	os << '<' << this->VerbosityText(entry->verbosity) << '>';
	if (console_ || file_)
	{
	   os << '<' << std::setiosflags(std::ios::fixed) << std::setprecision(6) << (static_cast<double>(entry->timestamp.QuadPart) / static_cast<double>(frequency_.QuadPart)) << '>';
//#define _LOG_THREAD_ID_
#ifdef _LOG_THREAD_ID_
	   os << '<' << entry->processName << ':' << entry->threadName << '>';
#endif
	}	
	if (!(entry->verbosity & LV_MESSAGE))
		os << '<' << entry->file << '(' << entry->line << ")>";
	os << '<' << entry->text << '>';
	return os.str();
}

const char* SimpleLoggerImpl::VerbosityText(enum LoggingVerbosity verbosity)
{
	switch (verbosity)
	{
	case LV_ERROR:
		return "ERROR";
	case LV_WARNING:
		return "WARNING";
	case LV_SYSTEM:
		return "SYSTEM";
	case LV_SOFTWARE:
		return "SOFTWARE";
	case LV_MESSAGE:
		return "MESSAGE";
	case LV_TRACE:
		return "TRACE";
	case LV_SPEED:
		return "SPEED";
	case LV_SPEED2:
		return "SPEED2";
	default:
		return "***UNKNOWN***";
	}
}

void SimpleLoggerImpl::timestampFile()
{
	char curTimeStr[64];
	time_t curTime = 0;
	::time(&curTime);
	VERIFY(!::ctime_s(curTimeStr, sizeof(curTimeStr)/sizeof(char), &curTime));

#if 0
	(*outStream_) << buf;
#else
	LARGE_INTEGER timestamp;
	VERIFY(::QueryPerformanceCounter(&timestamp));

	(*outStream_) << '<' << std::setiosflags(std::ios::fixed) << std::setprecision(6) 
		<< (static_cast<double>(timestamp.QuadPart) / static_cast<double>(frequency_.QuadPart)) << '>' 
		<< '<' << processName_ << '>'
		<< curTimeStr;
#endif
}

void SimpleLoggerImpl::startNewFile()
{
	// Close current file.  Calls rename.
	this->setFile(false, fileName_.c_str(), maxFileSize_, maxFiles_, cached_);

	// Reset the bytes logged to file counter.
	curFileSize_ = 0;

	// Restart file logging.
	this->setFile(true, fileName_.c_str(), maxFileSize_, maxFiles_, cached_);
}

void SimpleLoggerImpl::renameLogFile()
{
	// Rename the file.
	errno_t err = ::rename(fileName_.c_str(), this->getLogFileName(curFileIndex_).c_str());
	ASSERT(!err);

	// Delete old log file.
	if (maxFiles_ && (curFileIndex_ > maxFiles_))
	{
		// Ignore errors on this.  At the least is could occur when increasing maxFiles_.
		::_unlink(this->getLogFileName(curFileIndex_ - maxFiles_).c_str());
	}
	++curFileIndex_;
}

void SimpleLoggerImpl::initFileDateTimeString()
{
	// Get current date and time string.
	struct tm _tm;
	time_t utc = ::time(0);
	errno_t err = ::localtime_s(&_tm, &utc);
	ASSERT(!err);
	char buf[MAX_PATH];
	VERIFY(::strftime(buf, MAX_PATH, "_%Y-%m-%d_%H-%M-%S", &_tm));
	fileStartTimeString_ = buf;
}

std::string SimpleLoggerImpl::getLogFileName(size_t index)
{
	std::string retVal = fileName_;
	std::string newFileExt;
	std::string::size_type dotPos = retVal.rfind('.');
	if (std::string::npos != dotPos)
	{
		newFileExt = retVal.substr(dotPos);
		retVal.resize(dotPos);
	}
	retVal += fileStartTimeString_;
	retVal += '(';
	char aNum[16];
	retVal += ::ultoa(index, aNum, 10);
	retVal += ')';
	retVal += newFileExt;
	return retVal;
}

}
